Skip to content

Conversation

@KushnerovMikhail
Copy link

@KushnerovMikhail KushnerovMikhail commented May 16, 2024

Add profiling util based on periodic stack unwinding. Perf from Linux was taken as a reference.

Code is based on Sampling profiler (#29304) by @Jongy.

The operation of module is based on frame pointer usage and saving registers during interruption handling by zephyr.

General work description:
The unwinding function stay in timer as expiry function so is called during interruption handling. Thus the function have access to saved registers (program counter and frame pointer in particular) of the current thread and use it to unwind the thread stack.
Timer starting and results printing function are made as shell commands for conveniency.
Obtained samples can be translated into flamegraph using stackcollapse.py script.

Flame graph example, generated from echo_server sample:

graph

Kconfig optioins:

  • CONFIG_PERF enables perf subsystem in compilation.
  • CONFIG_PERF_BUFFER_SIZE specifies size of buffer, where samples are stored.

Kconfig requirements:

  • CONFIG_THREAD_STACK_INFO=y provides start and size thread stack values.
  • CONFIG_SMP=n SMP support is not implemented yet.
  • CONFIG_FRAME_POINTER=y provide frame pointer.
  • CONFIG_SHELL=y needs because subsystem provides shell commands.
  • CONFIG_RISCV=y || CONFIG_X86=y - subsystem implemented only for x86 and riscv yet.

@zephyrbot zephyrbot added area: X86 x86 Architecture (32-bit) area: Debugging area: RISCV RISCV Architecture (32-bit & 64-bit) area: Samples Samples labels May 16, 2024
@github-actions
Copy link

Hello @KushnerovMikhail, and thank you very much for your first pull request to the Zephyr project!
Our Continuous Integration pipeline will execute a series of checks on your Pull Request commit messages and code, and you are expected to address any failures by updating the PR. Please take a look at our commit message guidelines to find out how to format your commit messages, and at our contribution workflow to understand how to update your Pull Request. If you haven't already, please make sure to review the project's Contributor Expectations and update (by amending and force-pushing the commits) your pull request if necessary.
If you are stuck or need help please join us on Discord and ask your question there. Additionally, you can escalate the review when applicable. 😊

cfriedt
cfriedt previously approved these changes May 17, 2024
Copy link
Member

@cfriedt cfriedt left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

✨.Beautiful ✨.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Suggested change
./FlameGraph/flamegraph.pl perf_buf.foolded > graph.svg
./FlameGraph/flamegraph.pl perf_buf.folded > graph.svg

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks for the comment. Corrected it.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Suggested change
python zephyr/scripts/perf/stackcollapse.py perf_buf <build_dir>/zephyr/zephyr.elf > perf_buf.foolded
python zephyr/scripts/perf/stackcollapse.py perf_buf <build_dir>/zephyr/zephyr.elf > perf_buf.folded

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks for the comment. Corrected it.

Copy link
Member

@nashif nashif left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Please split the commit into multiple commits, i.e. 1 commit per arch, docs, adding the subsystem code and finally the sample.
Also, perf itself does not qualify as standalone subsystem. I suggest putting this under subsys/profiling/

@KushnerovMikhail KushnerovMikhail force-pushed the add_perf_x86_riscv branch 2 times, most recently from 830c289 to 20d23f2 Compare May 23, 2024 15:45
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

this was recently deprecated, can you please update? @ycsin fyi

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

this was recently deprecated, can you please update? @ycsin fyi

I think it makes sense for this subsys to use a generic arch level API provided in #73587

Copy link
Author

@KushnerovMikhail KushnerovMikhail Jul 4, 2024

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I am thinking about using API provided in #73587, but there are two issues, I have with it:

  • Riscv implementation do not check case when interruption occurred in function where $ra is not saved in stack frame (it can be if function does not call any other function). Seems like it leads to undefined behaviour (in this case frame->ra=$fp, frame->fp=<undefined>).
  • In riscv context saving code is same for exceptions and interruptions so during interruption registers are saved according to struct arch_esf. But for x86 there is separation between context saving during interruption and exception, and registers saved during interruption does not matches with struct arch_esf. And perf unwind stack during interruption.

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Fixed deprecated code

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think you are right, similar handling exists in Linux's implementation

@nashif nashif added this to the v4.0.0 milestone Jun 20, 2024
@KushnerovMikhail
Copy link
Author

KushnerovMikhail commented Jul 4, 2024

Added implementation for x86_32. For it I had to replace saving %edi with %ebp in interruption context saving code. Seems like it is not ruin anything.

Also I changed a little riscv stack unwinding code to avoid bug, when interruption occurs in function prologue or epilogue. The bug was that in epilogue/prologue fp is equal to pointer of previous function frame, and it looks like second from top function is missed.

graph
\/ improvement \/
graph
You can see that on the first graph sys_clock_cycle_get_32 is called not only from z_impl_k_busy_wait, that is wrong.

Rewrite subsystem with workqueue thread instead of events

@KushnerovMikhail KushnerovMikhail requested a review from nashif July 5, 2024 10:35
@ycsin
Copy link
Member

ycsin commented Jul 18, 2024

I am thinking about using API provided in #73587, but there are two issues, I have with it:

  • Riscv implementation do not check case when interruption occurred in function where $ra is not saved in stack frame (it can be if function does not call any other function). Seems like it leads to undefined behaviour (in this case frame->ra=$fp, frame->fp=<undefined>).
  • In riscv context saving code is same for exceptions and interruptions so during interruption registers are saved according to struct arch_esf. But for x86 there is separation between context saving during interruption and exception, and registers saved during interruption does not matches with struct arch_esf. And perf unwind stack during interruption.

I think from the project perspective it makes sense for applications/kernel to use the same stack-unwinding function so that there's less code duplication and easier to maintain in the long run, which is what the arch_stack_walk() in #73587 is trying to achieve.

I can probably fix the issue that you mentioned in RISC-V (edit: #76045 (edit: not correct yet (edit: should work now))). However, I do not know how stack unwinding works in x86/arm64, but I can massage their existing implementations to use the arch_stack_walk() (edit: #76042), hopefully that makes it a little easier for you to update this PR to use arch_stack_walk(), does this work for you?

Copy link
Member

@ycsin ycsin left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The changes to this file could probably be in another commit / PR to document this change better

@teburd
Copy link
Contributor

teburd commented Jul 18, 2024

Now we're cooking

@nashif
Copy link
Member

nashif commented Jul 18, 2024

looks good, will take another look so we can get it ready when main branch opens

Mikhail Kushnerov added 7 commits August 13, 2024 08:09
Add profiling subsystem.

Add perf util based on periodic stack unwinding. Perf from Linux
was taken as a reference.

The operation of module is based on frame pointer usage and saving
registers during interruption handling.
The unwinding function stay in timer as expiry functioin so is called
during interruption handling. Thus the function have access to saved
registers (program counter and frame pointer in particular) of the current
thread and use it to unwind the thread stack.
Timer starting and results printing function are made as shell commands
for conveniency.

Originally-by: Yonatan Goldschmidt <[email protected]>
Signed-off-by: Mikhail Kushnerov <[email protected]>
Implement stack trace function for riscv arch, that get required
thread register values and unwind stack with it.

Signed-off-by: Mikhail Kushnerov <[email protected]>
Implement stack trace function for x86_64 arch, that get required
thread register values and unwind stack with it.

Originally-by: Yonatan Goldschmidt <[email protected]>
Signed-off-by: Mikhail Kushnerov <[email protected]>
Implement stack trace function for x86_32 arch, that get required
thread register values and unwind stack with it.

Signed-off-by: Mikhail Kushnerov <[email protected]>
Samples, that were obtained by profiling perf tool, can be be translated
into flamegraph using stackcollapse.py script.

Originally-by: Yonatan Goldschmidt <[email protected]>
Signed-off-by: Mikhail Kushnerov <[email protected]>
Add doc for profiling perf tool

Signed-off-by: Mikhail Kushnerov <[email protected]>
The operation of perf tool can be checked using this sample.

Signed-off-by: Mikhail Kushnerov <[email protected]>
@nashif nashif force-pushed the add_perf_x86_riscv branch from eadbfb2 to bc9b550 Compare August 13, 2024 12:09
@nashif nashif merged commit 4f89e3c into zephyrproject-rtos:main Aug 13, 2024
@github-actions
Copy link

Hi @KushnerovMikhail!
Congratulations on getting your very first Zephyr pull request merged 🎉🥳. This is a fantastic achievement, and we're thrilled to have you as part of our community!

To celebrate this milestone and showcase your contribution, we'd love to award you the Zephyr Technical Contributor badge. If you're interested, please claim your badge by filling out this form: Claim Your Zephyr Badge.

Thank you for your valuable input, and we look forward to seeing more of your contributions in the future! 🪁

@kartben
Copy link
Contributor

kartben commented Aug 14, 2024

this new subsystem likely needs to be covered in the MAINTAINERS file, as it is orphan right now. cc @nashif

@KushnerovMikhail KushnerovMikhail deleted the add_perf_x86_riscv branch August 15, 2024 07:33
@KushnerovMikhail KushnerovMikhail restored the add_perf_x86_riscv branch August 15, 2024 07:43
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

area: Debugging area: RISCV RISCV Architecture (32-bit & 64-bit) area: Samples Samples area: X86 x86 Architecture (32-bit)

Projects

None yet

Development

Successfully merging this pull request may close these issues.

7 participants